fix(otel): end recording spans on non-terminal - #696
Conversation
95550ea to
0e1fd55
Compare
0e1fd55 to
51018c3
Compare
51018c3 to
610690e
Compare
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
af13837 to
3bbcad6
Compare
This comment has been minimized.
This comment has been minimized.
3bbcad6 to
ac01aaf
Compare
ac01aaf to
210ce63
Compare
This comment has been minimized.
This comment has been minimized.
210ce63 to
1d65bfb
Compare
| with self._lock: | ||
| if info.operation_id in self._ended_operation_ids: | ||
| return | ||
| self._ended_operation_ids.add(info.operation_id) |
This comment was marked as outdated.
This comment was marked as outdated.
Sorry, something went wrong.
| self._pop_span(info.operation_id) | ||
| parent = self._resolve_parent(info.parent_id) | ||
| self._start_span( | ||
| span = self._start_span( |
This comment was marked as outdated.
This comment was marked as outdated.
Sorry, something went wrong.
| with self._lock: | ||
| keys = list(reversed(self._operation_spans)) |
This comment was marked as outdated.
This comment was marked as outdated.
Sorry, something went wrong.
This comment has been minimized.
This comment has been minimized.
1d65bfb to
216222a
Compare
| with self._lock: | ||
| if info.operation_id in self._ended_operation_ids: | ||
| return | ||
| self._ended_operation_ids.add(info.operation_id) |
There was a problem hiding this comment.
Codex AI review · Finding arf_v1_2pna33ayjyhsqx2ehym77e3n7t
[P1] Do not re-export terminal contexts during replay. This set is reset after every invocation, so ReplayChildren contexts calling on_child_context_end(..., is_replayed=True) export the same deterministic span again on each replay. Collectors may overwrite or reject the original span. Skip replayed terminal callbacks or otherwise make export uniqueness execution-wide, and add a multi-invocation ReplayChildren test asserting one export.
| self._pop_span(info.operation_id) | ||
| parent = self._resolve_parent(info.parent_id) | ||
| self._start_span( | ||
| span = self._start_span( |
There was a problem hiding this comment.
Codex AI review · Finding arf_v1_5yc45ob4ohc33i7vrvqz7pezbu
[P2] Preserve a start timestamp for checkpointless contexts. on_child_context_end() captures end_time but supplies start_time=None, so this span starts at materialization time and is then ended using an earlier timestamp. Virtual and ReplayChildren context spans can consequently have negative durations. Store the user-function start time alongside the placeholder or include it in the end hook, and test both paths.
| with self._lock: | ||
| keys = list(reversed(self._operation_spans)) |
There was a problem hiding this comment.
Codex AI review · Finding arf_v1_dv5gcy7ci2c3j7gxu7vdwsejwy
[P2] Close attempts overwritten by in-process re-entry. This sweep can see only the latest span stored for each key. If an incomplete STEP re-enters the same attempt, _start_span() replaces the first recording span; ending the replacement then leaves the original unreachable and unended. End or retain the existing attempt before replacement, and extend the re-entry test to assert the original span is no longer recording.
Codex AI reviewFound three telemetry correctness issues, including replay-time duplicate deterministic spans. Review was read-only; tests were not executed as requested. Reviewed commit |
| def _end_open_recording_spans(self) -> None: | ||
| """End recording user-function spans left open by a suspended operation. | ||
|
|
||
| Operation placeholders are non-recording and export their span from | ||
| on_operation_end, so they are skipped. Reverse order keeps each child | ||
| contained within its parent; the invocation span is ended by the caller. | ||
| """ | ||
| with self._lock: | ||
| keys = list(reversed(self._operation_spans)) | ||
| for key in keys: | ||
| if key == _INVOCATION_KEY: | ||
| continue | ||
| span = self._get_span(key) | ||
| if span is None or not span.is_recording(): | ||
| continue | ||
| popped = self._pop_span(key) | ||
| if popped is not None: | ||
| popped.end() |
There was a problem hiding this comment.
Claude AI review · Finding arf_v1_d3v4nkts2wbw4vfdae6gv4poj6
_end_open_recording_spans() force-closes any recording span still open at invocation end (the realistic case is a STEP attempt whose outcome was INCOMPLETE, e.g. an in-process retry that didn't finish before the invocation suspended) by calling popped.end() with no status or attribute set. The exported span therefore has StatusCode.UNSET and none of the durable.attempt.* attributes that a normal completed attempt gets from on_user_function_end, so in a trace viewer it is indistinguishable from a short, uneventful successful attempt — hiding the fact that it was actually truncated because the invocation ended mid-attempt.
Consider setting an explicit marker before ending, e.g. popped.set_attribute("durable.span.truncated_at_invocation_boundary", True) (and/or leaving status UNSET is fine, but the attribute gives downstream consumers a way to distinguish this from a genuinely completed, short attempt).
Claude AI reviewThis PR replaces the previous "drop-without-ending" handling of open operation spans in I traced the full lifecycle (start/replay/suspend/resume/end, cross-invocation stitching, CONTEXT vs STEP vs WAIT/CALLBACK, duplicate One minor completeness gap remains (see inline comment): spans forcibly closed by Reviewed commit |
Issue #, if available:
#642
Description of changes:
By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.